Skip to content

Go 结构化日志:让一次事件能查到,也别把秘密写进去 ​

“创建订单失败”这句话只告诉你发生了什么;如果同一秒有几千个请求,还需要知道它属于哪个请求、失败在哪个阶段、用了多久。结构化日志把这些信息保留成字段,方便机器筛选,也方便人顺着调用过程定位。

本文用标准库 slog 建一个小日志入口,实际观察级别、context、请求 ID、脱敏和输出失败。示例固定 Go 1.27.2、Linux/amd64。为让输出可复现,示例特意移除了时间字段;生产日志通常应保留时间。

先确定一条事件应该长什么样 ​

字段示例用途及边界
msg / eventquote created稳定事件名,别把动态内容都拼进句子
levelINFO / WARN / ERROR描述事件严重程度,不直接等同告警策略
servicequote区分来源服务
request_idreq-42关联同一请求;不是授权凭据
total500数字保留数字类型,注明业务单位
elapsed1500000000本例 JSONHandler 的 Duration 为纳秒数
error_kindtimeout可用于聚合的错误类别,避免把秘密包含在完整错误字符串中

这张表是本例的事件契约建议。slog 的 Record 由时间、级别、消息与属性组成;Logger 负责发事件,Handler 决定过滤和输出。slog 概览

正在绘制图示…

可切换适合窗口或原始尺寸
查看图源代码
flowchart LR
    C["业务调用 InfoContext / LogAttrs"] --> L["Logger<br/>固定 service / request_id 属性"]
    L --> E["Handler.Enabled<br/>按级别判断"]
    E -->|"保留"| R["Record + Attr / LogValuer"]
    R --> H["JSONHandler / TextHandler / 自定义 Handler"]
    H --> W["io.Writer<br/>stdout、文件或其他目标"]
放大图示

原始尺寸下可横向或纵向滚动;按 Escape 关闭。

正在绘制图示…

查看图源代码
flowchart LR
    C["业务调用 InfoContext / LogAttrs"] --> L["Logger<br/>固定 service / request_id 属性"]
    L --> E["Handler.Enabled<br/>按级别判断"]
    E -->|"保留"| R["Record + Attr / LogValuer"]
    R --> H["JSONHandler / TextHandler / 自定义 Handler"]
    H --> W["io.Writer<br/>stdout、文件或其他目标"]

这表示默认同步调用过程,不暗示标准 Handler 自动带队列、后台发送或失败重试。输出后还要由采集系统处理,不能把“生成了 JSON”理解成“日志已经可靠入库”。Handler 契约

日常用到哪些入口 ​

操作入口说明
创建 JSON loggerslog.New(slog.NewJSONHandler(w, opts))明确写到哪个 writer
创建文本 loggerslog.NewTextHandler本地阅读方便,字段仍保留
发不同级别事件Debug、Info、Warn、Errorslog 的 Error 不会自动退出程序
添加固定属性logger.With(...)返回带额外属性的 logger,适合服务和请求范围
给字段分组WithGroup、slog.Group防止不同子系统字段混在一个层级
更明确的属性 APILogAttrs、slog.String/Int/Duration避免键值参数错位
运行中改级别slog.LevelVar支持安全并发读取和设置
接管全局调用slog.SetDefault会影响全局 slog 和默认 log 的行为,库一般不应擅自调用

这些 API 与行为见 Logger、LevelVar、SetDefault。建议在应用入口构造 logger,再传给组件;避免多个包分别修改全局输出。

级别改变过滤,不会自动改变告警 ​

go
var level slog.LevelVar
log := New(os.Stdout, &level).With("service", "quote")
log.DebugContext(ctx, "hidden")
log.InfoContext(ctx, "context alone")
level.Set(slog.LevelDebug)
log.Debug("debug enabled")

零值 LevelVar 的级别为 Info。第一条 Debug 被过滤;改级别后的 Debug 输出。本例完整程序最后一行为:

json
{"level":"DEBUG","msg":"debug enabled","service":"quote"}

建议 Info 记录值得长期保留的正常事件,Warn 记录有异常但尚可继续的情况,Error 记录操作失败;真正的等级定义应结合业务影响和恢复方式。对用户输入错误是否记 Warn,也要考虑常见程度,不能让正常的参数校验制造大量噪声。

告警还需要时间窗口、频率、错误比例和用户影响。一次可重试失败不一定应该半夜叫醒人;持续的 Warn 也可能意味着大面积服务受损。这是运维策略,不能只靠 if level == ERROR 完成。

被过滤的日志也可能先算完参数 ​

Go 在调用函数前求值参数,所以 log.Debug("snapshot", "data", expensiveSnapshot()) 即使最终被过滤,也可能已经做了昂贵计算。必要时先检查 log.Enabled(ctx, slog.LevelDebug),或用 LogValuer 延迟处理适合延迟的值。slog 性能说明、调用求值

这不意味着要到处手动加 if:先测量真实热点。日志字段越复杂,越需要考虑序列化、分配和下游写入的总成本,而不是只比较一次函数调用。

context 里有请求 ID,不代表日志会自动出现它 ​

示例把 req-42 放进 context,先直接调用 InfoContext,实际结果是:

json
{"level":"INFO","msg":"context alone","service":"quote"}

没有 request_id。标准 Handler 不会枚举并输出 context 中所有值;context 被交给 Handler,是否读取哪些值由实现决定。Handler.Handle

本例用一个明确的适配函数取出 ID,再加到 logger:

go
id, _ := ctx.Value(requestIDKey{}).(string)
return base.With("request_id", id)

随后记录报价事件:

json
{"level":"INFO","msg":"quote created","service":"quote","request_id":"req-42","total":500,"api_key":"[REDACTED]","elapsed":1500000000}

请求入口可以生成标识,或按跨服务约定验证并接收上游标识。不要无条件信任用户发来的任意 header:至少限制长度、字符和来源策略,不让客户端伪造大量关联或把控制字符带入日志。跨服务 trace ID 与单服务 request ID 也不完全相同;接入 tracing 时应遵守所选传播协议。本文没有实现分布式追踪和 header 生成,只验证显式注入的固定 ID。OWASP 日志输入与事件关联建议

脱敏要发生在信息进入日志之前 ​

给秘密值定义日志表示:

go
type Secret string
func (Secret) LogValue() slog.Value {
    return slog.StringValue("[REDACTED]")
}

slog.Any("api_key", Secret("sample-only")) 会通过 LogValuer 得到脱敏文本。本例测试确认原始 sample-only 不出现在这条输出里。LogValuer

但下面的写法会先把类型擦掉:

go
log.Info("unsafe formatted text", "value",
    fmt.Sprintf("%s", Secret("sample-only")))

现在传给 logger 的只是普通字符串,LogValuer 不再接到原始 Secret。测试确认输出包含示例值,日志为:

text
typed Secret redacted; preformatted string exposed the sample value

这是脱敏边界的反例,sample-only 是公开的测试数据,不是真实凭据。类似地,密钥可能藏在错误消息、URL 查询参数、请求体或连接串里,单靠筛掉 password 字段名不够。

本文建议先用字段允许清单,只记录确实需要的信息;再用类型级脱敏与输出端清洗做额外保护。不要默认打印整个请求对象、Authorization、Cookie、数据库连接串。日志访问权限、保留期限与删除流程也是保护的一部分。OWASP 不应记录的数据

级别、采样和高基数字段是三件事 ​

级别过滤按严重程度判断;采样决定大量相似事件保留多少;索引策略决定哪些字段进入昂贵的查询结构。请求 ID 几乎每次不同,属于高基数字段,但它仍有定位价值。是否索引、保留多久、能否作为指标标签,应根据采集后端和预算单独设计。

建议不要因为请求 ID 基数高就完全不记录,也不要把每个 request_id 直接搬成长期指标标签。大量重复错误可以采样并配合总量计数,但审计、安全或交易记录能否采样必须按其完整性要求判断。标准 JSONHandler 没有内建“自动每秒保留 N 条”的采样承诺,需要自定义 Handler 或所选后端支持;这是根据其公开选项范围作出的限定。HandlerOptions

输出失败和阻塞,不能指望 Info 返回 error ​

附录的 failWriter 永远返回 disk unavailable。直接调用 Handler.Handle 得到:

text
handler error=disk unavailable

但 Logger.Info 没有 error 返回值,Logger 会丢弃 Handler.Handle 返回的错误。需要可靠性要求时应单独监控日志输出故障,例如计数、健康状态或独立告警通道,避免失败日志又递归写回同一个失败 writer。Logger 的 Handler 错误处理、固定版本实现

JSONHandler 向 writer 写入发生在调用路径上。若 writer 阻塞,调用日志的请求也可能被拖住;自定义异步队列能隔离部分延迟,却又必须决定队列满时阻塞还是丢弃、退出时如何刷完、哪些事件不得丢失。本文没有测量日志后端吞吐量,也没有实现异步队列。JSONHandler、固定版本 handler 写入实现

日志应当帮你解释故障,不能在故障最严重时无上限占内存,或者把慢磁盘延迟传遍整个请求链。这个取舍比换一个 JSON 库更值得先讲清楚。

资料与实测范围 ​

主要依据为 Go 1.27.2 的 slog 文档、logger.go、handler.go,敏感日志处理参考 OWASP Logging Cheat Sheet。

2026-10-13 实际执行级别过滤与动态修改、context 不自动展开、显式请求 ID、Duration JSON 表示、LogValuer 脱敏及预格式化反例、writer 错误测试;race、vet 通过。移除时间字段仅为固定输出。没有实测网络采集、分布式追踪、采样或日志平台费用,不给 slog 与 zap 做性能排名。

完整程序与测试 ​

按以下路径保存,使用 Go 1.27.2。执行 go test -count=1 -v ./...、go test -count=1 -race ./...、go vet ./...,再运行 go run ./cmd/demo。所有秘密都是公开测试字符串;不要替换成真实密钥来观察泄漏反例。

cmd/demo/main.go ​

go
package main

import (
	"context"
	"example.com/v2/logging"
	"log/slog"
	"os"
	"time"
)

func main() {
	var level slog.LevelVar
	log := logging.New(os.Stdout, &level).With("service", "quote")
	ctx := logging.WithRequestID(context.Background(), "req-42")
	log.DebugContext(ctx, "hidden")
	log.InfoContext(ctx, "context alone")
	logging.RequestLogger(ctx, log).InfoContext(ctx, "quote created", slog.Int("total", 500), slog.Any("api_key", logging.Secret("sample-only")), slog.Duration("elapsed", 1500*time.Millisecond))
	level.Set(slog.LevelDebug)
	log.Debug("debug enabled")
}

go.mod ​

go.mod
module example.com/v2/logging

go 1.27.2

logging.go ​

go
package logging

import (
	"context"
	"io"
	"log/slog"
)

type Secret string

func (Secret) LogValue() slog.Value { return slog.StringValue("[REDACTED]") }
func New(w io.Writer, level *slog.LevelVar) *slog.Logger {
	return slog.New(slog.NewJSONHandler(w, &slog.HandlerOptions{Level: level, ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.TimeKey {
			return slog.Attr{}
		}
		return a
	}}))
}

type requestIDKey struct{}

func WithRequestID(ctx context.Context, id string) context.Context {
	return context.WithValue(ctx, requestIDKey{}, id)
}
func RequestLogger(ctx context.Context, base *slog.Logger) *slog.Logger {
	id, _ := ctx.Value(requestIDKey{}).(string)
	return base.With("request_id", id)
}

logging_test.go ​

代码块 · 58 行 · 点击收起 / 展开
go
package logging

import (
	"bytes"
	"context"
	"fmt"
	"log/slog"
	"strings"
	"testing"
	"time"
)

func Example() {
	var out bytes.Buffer
	var level slog.LevelVar
	log := New(&out, &level).With("service", "quote")
	ctx := WithRequestID(context.Background(), "req-42")
	log.DebugContext(ctx, "hidden")
	log.InfoContext(ctx, "context alone")
	RequestLogger(ctx, log).InfoContext(ctx, "quote created", slog.Int("total", 500), slog.Any("api_key", Secret("sample-only")), slog.Duration("elapsed", 1500*time.Millisecond))
	level.Set(slog.LevelDebug)
	log.Debug("debug enabled")
	fmt.Print(out.String())
	// Output:
	// {"level":"INFO","msg":"context alone","service":"quote"}
	// {"level":"INFO","msg":"quote created","service":"quote","request_id":"req-42","total":500,"api_key":"[REDACTED]","elapsed":1500000000}
	// {"level":"DEBUG","msg":"debug enabled","service":"quote"}
}
func TestSecretBoundary(t *testing.T) {
	var out bytes.Buffer
	var level slog.LevelVar
	log := New(&out, &level)
	log.Info("safe", "value", Secret("sample-only"))
	if strings.Contains(out.String(), "sample-only") {
		t.Fatal("secret leaked")
	}
	out.Reset()
	log.Info("unsafe formatted text", "value", fmt.Sprintf("%s", Secret("sample-only")))
	if !strings.Contains(out.String(), "sample-only") {
		t.Fatal("expected boundary demonstration")
	}
	t.Log("typed Secret redacted; preformatted string exposed the sample value")
}

type failWriter struct{}

func (failWriter) Write([]byte) (int, error) { return 0, fmt.Errorf("disk unavailable") }
func TestHandlerError(t *testing.T) {
	h := slog.NewJSONHandler(failWriter{}, nil)
	r := slog.NewRecord(time.Time{}, slog.LevelInfo, "event", 0)
	if err := h.Handle(context.Background(), r); err == nil {
		t.Fatal("expected write error")
	} else {
		t.Logf("handler error=%v", err)
	}
	// Logger.Info has no error result. Production output health needs separate monitoring.
	slog.New(h).Info("event")
}

保留各书来源与许可 · 示例运行条件以正文为准